[INFO] fetching crate logwise 0.5.1...
[INFO] testing logwise-0.5.1 against try#0abe69e6c16114311cc2700e972492e64d69c28f for pr-154065-1
[INFO] extracting crate logwise 0.5.1 into /workspace/builds/worker-3-tc2/source
[INFO] started tweaking crates.io crate logwise 0.5.1
[INFO] removed 0 missing tests
[INFO] finished tweaking crates.io crate logwise 0.5.1
[INFO] tweaked toml for crates.io crate logwise 0.5.1 written to /workspace/builds/worker-3-tc2/source/Cargo.toml
[INFO] validating manifest of crates.io crate logwise 0.5.1 on toolchain 0abe69e6c16114311cc2700e972492e64d69c28f
[INFO] running `Command { std: CARGO_HOME="/workspace/cargo-home" RUSTUP_HOME="/workspace/rustup-home" "/workspace/cargo-home/bin/cargo" "+0abe69e6c16114311cc2700e972492e64d69c28f" "metadata" "--manifest-path" "Cargo.toml" "--no-deps", kill_on_drop: false }`
[INFO] crate crates.io crate logwise 0.5.1 already has a lockfile, it will not be regenerated
[INFO] running `Command { std: CARGO_HOME="/workspace/cargo-home" RUSTUP_HOME="/workspace/rustup-home" "/workspace/cargo-home/bin/cargo" "+0abe69e6c16114311cc2700e972492e64d69c28f" "fetch" "--manifest-path" "Cargo.toml", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "create" "-v" "/var/lib/crater-agent-workspace/builds/worker-3-tc2/target:/opt/rustwide/target:rw,Z" "-v" "/var/lib/crater-agent-workspace/builds/worker-3-tc2/source:/opt/rustwide/workdir:ro,Z" "-v" "/var/lib/crater-agent-workspace/cargo-home:/opt/rustwide/cargo-home:ro,Z" "-v" "/var/lib/crater-agent-workspace/rustup-home:/opt/rustwide/rustup-home:ro,Z" "-e" "SOURCE_DIR=/opt/rustwide/workdir" "-e" "CARGO_TARGET_DIR=/opt/rustwide/target" "-e" "CARGO_HOME=/opt/rustwide/cargo-home" "-e" "RUSTUP_HOME=/opt/rustwide/rustup-home" "-w" "/opt/rustwide/workdir" "-m" "1610612736" "--user" "0:0" "--network" "none" "ghcr.io/rust-lang/crates-build-env/linux@sha256:d429b63d4308055ea97f60fb1d3dfca48854a00942f1bd2ad806beaf015945ec" "/opt/rustwide/cargo-home/bin/cargo" "+0abe69e6c16114311cc2700e972492e64d69c28f" "metadata" "--no-deps" "--format-version=1", kill_on_drop: false }`
[INFO] [stdout] 9ed9f666468373c68ea58e4cfc7021defd3c19173e150ab921d434f7df9cf0b2
[INFO] running `Command { std: "docker" "start" "-a" "9ed9f666468373c68ea58e4cfc7021defd3c19173e150ab921d434f7df9cf0b2", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "inspect" "9ed9f666468373c68ea58e4cfc7021defd3c19173e150ab921d434f7df9cf0b2", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "rm" "-f" "9ed9f666468373c68ea58e4cfc7021defd3c19173e150ab921d434f7df9cf0b2", kill_on_drop: false }`
[INFO] [stdout] 9ed9f666468373c68ea58e4cfc7021defd3c19173e150ab921d434f7df9cf0b2
[INFO] running `Command { std: "docker" "create" "-v" "/var/lib/crater-agent-workspace/builds/worker-3-tc2/target:/opt/rustwide/target:rw,Z" "-v" "/var/lib/crater-agent-workspace/builds/worker-3-tc2/source:/opt/rustwide/workdir:ro,Z" "-v" "/var/lib/crater-agent-workspace/cargo-home:/opt/rustwide/cargo-home:ro,Z" "-v" "/var/lib/crater-agent-workspace/rustup-home:/opt/rustwide/rustup-home:ro,Z" "-e" "SOURCE_DIR=/opt/rustwide/workdir" "-e" "CARGO_TARGET_DIR=/opt/rustwide/target" "-e" "CARGO_INCREMENTAL=0" "-e" "RUST_BACKTRACE=full" "-e" "RUSTFLAGS=--cap-lints=forbid" "-e" "RUSTDOCFLAGS=--cap-lints=forbid" "-e" "CARGO_HOME=/opt/rustwide/cargo-home" "-e" "RUSTUP_HOME=/opt/rustwide/rustup-home" "-w" "/opt/rustwide/workdir" "-m" "1610612736" "--user" "0:0" "--network" "none" "ghcr.io/rust-lang/crates-build-env/linux@sha256:d429b63d4308055ea97f60fb1d3dfca48854a00942f1bd2ad806beaf015945ec" "/opt/rustwide/cargo-home/bin/cargo" "+0abe69e6c16114311cc2700e972492e64d69c28f" "build" "--frozen" "--message-format=json", kill_on_drop: false }`
[INFO] [stdout] 1aa74306184adbb35026620e95d6a0a88eb0f64fba1ad97bb76fe0c7bafcc89a
[INFO] running `Command { std: "docker" "start" "-a" "1aa74306184adbb35026620e95d6a0a88eb0f64fba1ad97bb76fe0c7bafcc89a", kill_on_drop: false }`
[INFO] [stderr]    Compiling quote v1.0.44
[INFO] [stderr]    Compiling unicode-ident v1.0.23
[INFO] [stderr]    Compiling thiserror v2.0.18
[INFO] [stderr]    Compiling wasm_safe_thread v0.1.1
[INFO] [stderr]    Compiling logwise_proc v0.5.0
[INFO] [stderr]    Compiling proc-macro2 v1.0.106
[INFO] [stderr]    Compiling syn v2.0.115
[INFO] [stderr]    Compiling thiserror-impl v2.0.18
[INFO] [stderr]    Compiling continue v0.1.2
[INFO] [stderr]    Compiling logwise v0.5.1 (/opt/rustwide/workdir)
[INFO] [stderr]     Finished `dev` profile [unoptimized + debuginfo] target(s) in 5.54s
[INFO] running `Command { std: "docker" "inspect" "1aa74306184adbb35026620e95d6a0a88eb0f64fba1ad97bb76fe0c7bafcc89a", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "rm" "-f" "1aa74306184adbb35026620e95d6a0a88eb0f64fba1ad97bb76fe0c7bafcc89a", kill_on_drop: false }`
[INFO] [stdout] 1aa74306184adbb35026620e95d6a0a88eb0f64fba1ad97bb76fe0c7bafcc89a
[INFO] running `Command { std: "docker" "create" "-v" "/var/lib/crater-agent-workspace/builds/worker-3-tc2/target:/opt/rustwide/target:rw,Z" "-v" "/var/lib/crater-agent-workspace/builds/worker-3-tc2/source:/opt/rustwide/workdir:ro,Z" "-v" "/var/lib/crater-agent-workspace/cargo-home:/opt/rustwide/cargo-home:ro,Z" "-v" "/var/lib/crater-agent-workspace/rustup-home:/opt/rustwide/rustup-home:ro,Z" "-e" "SOURCE_DIR=/opt/rustwide/workdir" "-e" "CARGO_TARGET_DIR=/opt/rustwide/target" "-e" "CARGO_INCREMENTAL=0" "-e" "RUST_BACKTRACE=full" "-e" "RUSTFLAGS=--cap-lints=forbid" "-e" "RUSTDOCFLAGS=--cap-lints=forbid" "-e" "CARGO_HOME=/opt/rustwide/cargo-home" "-e" "RUSTUP_HOME=/opt/rustwide/rustup-home" "-w" "/opt/rustwide/workdir" "-m" "1610612736" "--user" "0:0" "--network" "none" "ghcr.io/rust-lang/crates-build-env/linux@sha256:d429b63d4308055ea97f60fb1d3dfca48854a00942f1bd2ad806beaf015945ec" "/opt/rustwide/cargo-home/bin/cargo" "+0abe69e6c16114311cc2700e972492e64d69c28f" "test" "--frozen" "--no-run" "--message-format=json", kill_on_drop: false }`
[INFO] [stdout] 920c353cc3ba7a3844be9e49613aebf544005847eaf4bc66dcbd4afb03fcc65b
[INFO] running `Command { std: "docker" "start" "-a" "920c353cc3ba7a3844be9e49613aebf544005847eaf4bc66dcbd4afb03fcc65b", kill_on_drop: false }`
[INFO] [stderr]    Compiling winnow v0.7.14
[INFO] [stderr]    Compiling equivalent v1.0.2
[INFO] [stderr]    Compiling hashbrown v0.16.1
[INFO] [stderr]    Compiling toml_datetime v0.7.5+spec-1.1.0
[INFO] [stderr]    Compiling priority v0.1.1
[INFO] [stderr]    Compiling syn v2.0.115
[INFO] [stderr]    Compiling indexmap v2.13.0
[INFO] [stderr]    Compiling toml_parser v1.0.8+spec-1.1.0
[INFO] [stderr]    Compiling toml_edit v0.23.10+spec-1.0.0
[INFO] [stderr]    Compiling proc-macro-crate v3.4.0
[INFO] [stderr]    Compiling thiserror-impl v2.0.18
[INFO] [stderr]    Compiling test_executors_proc v0.3.5
[INFO] [stderr]    Compiling thiserror v2.0.18
[INFO] [stderr]    Compiling continue v0.1.2
[INFO] [stderr]    Compiling wasm_safe_thread v0.1.1
[INFO] [stderr]    Compiling wasm_safe_mutex v0.1.2
[INFO] [stderr]    Compiling some_executor v0.6.3
[INFO] [stderr]    Compiling logwise v0.5.1 (/opt/rustwide/workdir)
[INFO] [stderr]    Compiling logwise v0.5.0
[INFO] [stderr]    Compiling test_executors v0.4.1
[INFO] [stderr]     Finished `test` profile [unoptimized + debuginfo] target(s) in 7.81s
[INFO] running `Command { std: "docker" "inspect" "920c353cc3ba7a3844be9e49613aebf544005847eaf4bc66dcbd4afb03fcc65b", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "rm" "-f" "920c353cc3ba7a3844be9e49613aebf544005847eaf4bc66dcbd4afb03fcc65b", kill_on_drop: false }`
[INFO] [stdout] 920c353cc3ba7a3844be9e49613aebf544005847eaf4bc66dcbd4afb03fcc65b
[INFO] running `Command { std: "docker" "create" "-v" "/var/lib/crater-agent-workspace/builds/worker-3-tc2/target:/opt/rustwide/target:rw,Z" "-v" "/var/lib/crater-agent-workspace/builds/worker-3-tc2/source:/opt/rustwide/workdir:ro,Z" "-v" "/var/lib/crater-agent-workspace/cargo-home:/opt/rustwide/cargo-home:ro,Z" "-v" "/var/lib/crater-agent-workspace/rustup-home:/opt/rustwide/rustup-home:ro,Z" "-e" "SOURCE_DIR=/opt/rustwide/workdir" "-e" "CARGO_TARGET_DIR=/opt/rustwide/target" "-e" "CARGO_INCREMENTAL=0" "-e" "RUST_BACKTRACE=full" "-e" "RUSTFLAGS=--cap-lints=forbid" "-e" "RUSTDOCFLAGS=--cap-lints=forbid" "-e" "CARGO_HOME=/opt/rustwide/cargo-home" "-e" "RUSTUP_HOME=/opt/rustwide/rustup-home" "-w" "/opt/rustwide/workdir" "-m" "1610612736" "--user" "0:0" "--network" "none" "ghcr.io/rust-lang/crates-build-env/linux@sha256:d429b63d4308055ea97f60fb1d3dfca48854a00942f1bd2ad806beaf015945ec" "/opt/rustwide/cargo-home/bin/cargo" "+0abe69e6c16114311cc2700e972492e64d69c28f" "test" "--frozen", kill_on_drop: false }`
[INFO] [stdout] 992d54765088353ed8f8ea7c4e8d3d85b3ec0d23769702b3d4369946c18c1d66
[INFO] running `Command { std: "docker" "start" "-a" "992d54765088353ed8f8ea7c4e8d3d85b3ec0d23769702b3d4369946c18c1d66", kill_on_drop: false }`
[INFO] [stderr]     Finished `test` profile [unoptimized + debuginfo] target(s) in 0.10s
[INFO] [stderr]      Running unittests src/lib.rs (/opt/rustwide/target/debug/deps/logwise-d0ca1560fbc41356)
[INFO] [stdout] 
[INFO] [stdout] running 25 tests
[INFO] [stderr] 2 Finished task `new_task`
[INFO] [stderr] 5 Finished task `different_task`
[INFO] [stderr] 3 Finished task `test_context_hash`
[INFO] [stderr] 0 Finished task `test_as_ref`
[INFO] [stderr]  6 INFO: src/dispatch.rs:835:9 [0ns] test_perfwarn
[INFO] [stderr]  6 PERFWARN: BEGIN src/dispatch.rs:836:22 [35.65µs] test_perfwarn interval name
[INFO] [stderr]  6 PERWARN: END [52.63µs] test_perfwarn interval name [interval took 560ns] 
[INFO] [stderr] 6 PERFWARN: statistics[test_perfwarn interval name: 560ns]
[INFO] [stderr] 6 Finished task `test_perfwarn`
[INFO] [stderr]  10 DEBUG: src/dispatch.rs:864:9 [391.26µs] S(23)!
[INFO] [stderr] 10 Finished task `test_log_custom`
[INFO] [stderr]  8 DEBUG: src/dispatch.rs:845:9 [184.05µs] test_debuginternal_sync
[INFO] [stderr] 8 Finished task `test_debuginternal_sync`
[INFO] [stderr]  12 MANDATORY: src/dispatch.rs:889:9 [763.64µs] mandatory debug value=42
[INFO] [stderr] 12 Finished task `test_mandatory_sync`
[INFO] [stderr]  14 PROFILE: BEGIN [id=1] src/dispatch.rs:922:5 [964.1µs] logwise::dispatch::tests::profiled_function
[INFO] [stderr]  14 PROFILE: END [id=1] [elapsed: 2.371µs] logwise::dispatch::tests::profiled_function
[INFO] [stderr] 14 Finished task `test_profile_attribute`
[INFO] [stdout] test context::tests::test_context_as_ref_task ... ok
[INFO] [stdout] test context::tests::test_context_hash ... ok
[INFO] [stdout] test dispatch::tests::perfwarn ... ok
[INFO] [stdout] test dispatch::tests::test_log_custom ... ok
[INFO] [stdout] test dispatch::tests::test_debuginternal_sync ... ok
[INFO] [stdout] test dispatch::tests::test_mandatory_sync ... ok
[INFO] [stdout] test dispatch::tests::test_profile_attribute ... ok
[INFO] [stdout] test global_logger::tests::test_add_logger ... ok
[INFO] [stdout] test global_logger::tests::test_set_loggers ... ok
[INFO] [stdout] test heartbeat::tests::assert_send_sync ... ok
[INFO] [stdout] test dispatch::tests::test_profile_begin ... ok
[INFO] [stdout] test interval::tests::assert_send_sync ... ok
[INFO] [stderr]  18 DEBUG: src/dispatch.rs:853:9 [1.21068ms] Hello false!
[INFO] [stderr]  20 PROFILE: src/dispatch.rs:896:9 [1.368851ms] profile timing=100ms
[INFO] [stderr] 18 Finished task `test_log_rich`
[INFO] [stdout] test dispatch::tests::test_log_rich ... ok
[INFO] [stderr]  22 INFO: src/dispatch.rs:826:9 [1.441001ms] test_warn_sync
[INFO] [stdout] test macros::tests::test_logging_domain_trait_implementations ... ok
[INFO] [stderr]  22 WARN: src/dispatch.rs:827:9 [2.098851ms] test_warn_sync Hello 23!
[INFO] [stderr] 22 Finished task `test_warn_sync`
[INFO] [stderr] 20 Finished task `test_profile_sync`
[INFO] [stdout] test dispatch::tests::test_profile_sync ... ok
[INFO] [stdout] test dispatch::tests::test_warn_sync ... ok
[INFO] [stderr] 26 Finished task `test_trace`
[INFO] [stderr] 24 Finished task `test_log_info_async`
[INFO] [stdout] test dispatch::tests::test_log_info_async ... ok
[INFO] [stdout] test dispatch::tests::test_trace ... ok
[INFO] [stderr] 28 Finished task `test_new_context`
[INFO] [stdout] test context::tests::test_new_context ... ok
[INFO] [stdout] test context::tests::test_context_display ... ok
[INFO] [stderr] 30 Finished task `root_task`
[INFO] [stderr] 32 Finished task `child_task`
[INFO] [stderr]  33 PROFILE: BEGIN [id=3] src/dispatch.rs:948:5 [14.095505ms] logwise::dispatch::tests::profiled_early_return
[INFO] [stderr]  33 PROFILE: END [id=3] [elapsed: 980ns] logwise::dispatch::tests::profiled_early_return
[INFO] [stderr]  33 PROFILE: BEGIN [id=4] src/dispatch.rs:948:5 [14.157435ms] logwise::dispatch::tests::profiled_early_return
[INFO] [stderr]  33 PROFILE: END [id=4] [elapsed: 400ns] logwise::dispatch::tests::profiled_early_return
[INFO] [stderr] 33 Finished task `test_profile_attribute_early_return`
[INFO] [stdout] test dispatch::tests::test_profile_attribute_early_return ... ok
[INFO] [stderr] 37 Finished task `different_task`
[INFO] [stderr] 35 Finished task `test_context_equality`
[INFO] [stdout] test context::tests::test_context_equality ... ok
[INFO] [stdout] test global_logger::tests::test_thread_safety ... ok
[INFO] [stderr]  38 PROFILE: BEGIN [id=5] src/dispatch.rs:935:5 [47.108176ms] logwise::dispatch::tests::profiled_with_args
[INFO] [stderr]  38 PROFILE: END [id=5] [elapsed: 620ns] logwise::dispatch::tests::profiled_with_args
[INFO] [stderr] 38 Finished task `test_profile_attribute_with_args`
[INFO] [stderr]  40 PROFILE: BEGIN [id=6] src/dispatch.rs:913:21 [47.275686ms] outer_operation
[INFO] [stderr]  40 PROFILE: BEGIN [id=7] src/dispatch.rs:915:25 [47.296026ms] inner_operation
[INFO] [stderr]  40 PROFILE: END [id=7] [elapsed: 1.59µs] inner_operation
[INFO] [stderr]  40 PROFILE: END [id=6] [elapsed: 28.42µs] outer_operation
[INFO] [stderr] 40 Finished task `test_profile_begin_nested`
[INFO] [stdout] test dispatch::tests::test_profile_attribute_with_args ... ok
[INFO] [stdout] test dispatch::tests::test_profile_begin_nested ... ok
[INFO] [stdout] 
[INFO] [stdout] test result: ok. 25 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.05s
[INFO] [stdout] 
[INFO] [stderr]      Running tests/debuginternal.rs (/opt/rustwide/target/debug/deps/debuginternal-af4e4baac93c47d8)
[INFO] [stdout] 
[INFO] [stdout] running 1 test
[INFO] [stderr]  0 DEBUG: tests/debuginternal.rs:19:5 [0ns] test message
[INFO] [stderr] 0 Finished task `test_debuginternal`
[INFO] [stdout] test test_debuginternal_enabled_in_integration_test ... ok
[INFO] [stdout] 
[INFO] [stdout] test result: ok. 1 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.01s
[INFO] [stdout] 
[INFO] [stderr]      Running tests/heartbeat.rs (/opt/rustwide/target/debug/deps/heartbeat-cd67905247a98d80)
[INFO] [stdout] 
[INFO] [stdout] running 2 tests
[INFO] [stdout] test tests::async_test_heartbeat_on_time_emits_no_logs ... ok
[INFO] [stdout] test tests::async_test_heartbeat_logs_missed_deadline_and_late_drop ... ok
[INFO] [stdout] 
[INFO] [stdout] test result: ok. 2 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.10s
[INFO] [stdout] 
[INFO] [stderr]      Running tests/macro_refactor.rs (/opt/rustwide/target/debug/deps/macro_refactor-0c3b9f702b990eeb)
[INFO] [stdout] 
[INFO] [stdout] running 1 test
[INFO] [stderr] T0 TRACE: src/context/context_impl.rs:429:9 [0ns] Begin trace
[INFO] [stdout] test tests::test_log_enabled ... ok
[INFO] [stdout] 
[INFO] [stdout] test result: ok. 1 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.00s
[INFO] [stdout] 
[INFO] [stdout] 
[INFO] [stdout] running 3 tests
[INFO] [stderr]      Running tests/perfwarn_if.rs (/opt/rustwide/target/debug/deps/perfwarn_if-91b3235ed46f26e6)
[INFO] [stderr] 5 Finished task `test_perfwarn_if_fast`
[INFO] [stdout] test test_perfwarn_if_skips_when_fast ... ok
[INFO] [stderr]  0 PERFWARN: tests/perfwarn_if.rs:12:20 [0ns] slow_operation is SLOW: [interval took 50.085717ms] 
[INFO] [stderr] 0 PERFWARN: statistics[slow_operation: 50.085717ms]
[INFO] [stderr] 0 Finished task `test_perfwarn_if_slow`
[INFO] [stdout] test test_perfwarn_if_logs_when_slow ... ok
[INFO] [stderr]   4 PERFWARN: tests/perfwarn_if.rs:58:24 [1.11984ms] slow_stat is SLOW: [interval took 50.078886ms] 
[INFO] [stderr] 2 Finished task `test_perfwarn_if_stats`
[INFO] [stderr] 4 PERFWARN: statistics[slow_stat: 50.078886ms]
[INFO] [stderr] 4 Finished task `stats_task`
[INFO] [stdout] test test_perfwarn_if_statistics ... ok
[INFO] [stdout] 
[INFO] [stdout] test result: ok. 3 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.05s
[INFO] [stdout] 
[INFO] [stderr]    Doc-tests logwise
[INFO] [stdout] 
[INFO] [stdout] running 124 tests
[INFO] [stdout] test src/context.rs - context (line 100) ... ok
[INFO] [stdout] test src/context/context_impl.rs - context::context_impl::Context::currently_tracing (line 372) ... ok
[INFO] [stdout] test src/context/context_impl.rs - context::context_impl::Context::nesting_level (line 464) ... ok
[INFO] [stdout] test src/context/context_impl.rs - context::context_impl::Context (line 53) ... ok
[INFO] [stdout] test src/context/apply_context.rs - context::apply_context::ApplyContext<F>::new (line 69) ... ok
[INFO] [stdout] test src/context/context_impl.rs - context::context_impl::Context::is_tracing (line 352) ... ok
[INFO] [stdout] test src/context/context_impl.rs - context::context_impl::Context (line 76) ... ok
[INFO] [stdout] test src/context.rs - context (line 24) ... ok
[INFO] [stdout] test src/context/apply_context.rs - context::apply_context::ApplyContext (line 25) ... ok
[INFO] [stdout] test src/context/context_impl.rs - context::context_impl::Context::pop (line 515) ... ok
[INFO] [stdout] test src/context/context_impl.rs - context::context_impl::Context::current (line 151) ... ok
[INFO] [stdout] test src/context/context_impl.rs - context::context_impl::Context::from_parent (line 301) ... ok
[INFO] [stdout] test src/context/context_impl.rs - context::context_impl::Context::begin_trace (line 408) ... ok
[INFO] [stdout] test src/context.rs - context (line 83) ... ok
[INFO] [stdout] test src/context/context_impl.rs - context::context_impl::Context::new_task (line 209) ... ok
[INFO] [stdout] test src/context/context_impl.rs - context::context_impl::Context::context_id (line 492) ... ok
[INFO] [stdout] test src/context/context_impl.rs - context::context_impl::Context::task_id (line 333) ... ok
[INFO] [stdout] test src/context/context_impl.rs - context::context_impl::Context::set_current (line 439) ... ok
[INFO] [stdout] test src/context/context_impl.rs - context::context_impl::Context::reset (line 265) ... ok
[INFO] [stdout] test src/dispatch.rs - dispatch::debuginternal_pre (line 46) ... ok
[INFO] [stdout] test src/context/task.rs - context::task::Task (line 40) ... ok
[INFO] [stdout] test src/context.rs - context (line 42) ... ok
[INFO] [stdout] test src/context/context_impl.rs - context::context_impl::Context::task (line 173) ... ok
[INFO] [stdout] test src/dispatch.rs - dispatch::error_sync_pre (line 409) ... ok
[INFO] [stdout] test src/dispatch.rs - dispatch::error_sync_post (line 446) ... ok
[INFO] [stdout] test src/dispatch.rs - dispatch::debuginternal_async_post (line 110) ... ok
[INFO] [stdout] test src/dispatch.rs - dispatch::error_async_post (line 472) ... ok
[INFO] [stdout] test src/dispatch.rs - dispatch::perfwarn_begin_post (line 553) ... ok
[INFO] [stdout] test src/dispatch.rs - dispatch::info_async_post (line 209) ... ok
[INFO] [stdout] test src/dispatch.rs - dispatch::perfwarn_begin_pre (line 507) ... ok
[INFO] [stdout] test src/dispatch.rs - dispatch::trace_async_post (line 375) ... ok
[INFO] [stdout] test src/dispatch.rs - dispatch::info_sync_pre (line 144) ... ok
[INFO] [stdout] test src/context.rs - context (line 63) ... ok
[INFO] [stdout] test src/dispatch.rs - dispatch::debuginternal_sync_post (line 84) ... ok
[INFO] [stdout] test src/global_logger.rs - global_logger (line 43) ... ok
[INFO] [stdout] test src/dispatch.rs - dispatch::info_sync_post (line 181) ... ok
[INFO] [stdout] test src/dispatch.rs - dispatch::warn_sync_post (line 280) ... ok
[INFO] [stdout] test src/dispatch.rs - dispatch::trace_sync_pre (line 312) ... ok
[INFO] [stdout] test src/dispatch.rs - dispatch::trace_sync_post (line 349) ... ok
[INFO] [stdout] test src/dispatch.rs - dispatch::warn_sync_pre (line 243) ... ok
[INFO] [stdout] test src/global_logger.rs - global_logger (line 33) ... ok
[INFO] [stdout] test src/global_logger.rs - global_logger::add_global_logger (line 178) ... ok
[INFO] [stdout] test src/global_logger.rs - global_logger::set_global_loggers (line 283) ... ok
[INFO] [stdout] test src/global_logger.rs - global_logger (line 61) ... ok
[INFO] [stdout] test src/global_logger.rs - global_logger::set_global_loggers (line 261) ... ok
[INFO] [stdout] test src/heartbeat.rs - heartbeat::HeartbeatGuard::new (line 124) ... ok
[INFO] [stdout] test src/heartbeat.rs - heartbeat::HeartbeatGuard::new (line 139) ... ok
[INFO] [stdout] test src/heartbeat.rs - heartbeat::heartbeat (line 332) ... ok
[INFO] [stdout] test src/inmemory_logger.rs - inmemory_logger::InMemoryLogger (line 75) ... ok
[INFO] [stdout] test src/inmemory_logger.rs - inmemory_logger::InMemoryLogger::drain_logs (line 191) ... ok
[INFO] [stdout] test src/global_logger.rs - global_logger::global_loggers (line 139) ... ok
[INFO] [stdout] test src/inmemory_logger.rs - inmemory_logger::InMemoryLogger::drain_to_console (line 239) ... ok
[INFO] [stdout] test src/global_logger.rs - global_logger::set_global_loggers (line 243) ... ok
[INFO] [stdout] test src/global_logger.rs - global_logger::add_global_logger (line 195) ... ok
[INFO] [stdout] test src/inmemory_logger.rs - inmemory_logger::InMemoryLogger::new (line 166) ... ok
[INFO] [stdout] test src/heartbeat.rs - heartbeat::heartbeat (line 348) ... ok
[INFO] [stdout] test src/level.rs - level::Level::DebugInternal (line 64) ... ok
[INFO] [stdout] test src/inmemory_logger.rs - inmemory_logger::InMemoryLogger (line 107) ... ok
[INFO] [stdout] test src/heartbeat.rs - heartbeat::HeartbeatGuard (line 79) ... ok
[INFO] [stdout] test src/inmemory_logger.rs - inmemory_logger::InMemoryLogger::periodic_drain_to_console (line 293) ... ok
[INFO] [stdout] test src/inmemory_logger.rs - inmemory_logger::InMemoryLogger (line 47) ... ok
[INFO] [stdout] test src/level.rs - level::Level::Warning (line 117) ... ok
[INFO] [stdout] test src/level.rs - level::Level::Mandatory (line 152) ... ok
[INFO] [stdout] test src/interval.rs - interval::PerfwarnIntervalIf::new (line 216) ... ok
[INFO] [stdout] test src/level.rs - level::Level::Profile (line 166) ... ok
[INFO] [stdout] test src/level.rs - level::Level::Error (line 131) ... ok
[INFO] [stdout] test src/level.rs - level::Level::Trace (line 47) ... ok
[INFO] [stdout] test src/interval.rs - interval::PerfwarnInterval (line 56) ... ok
[INFO] [stdout] test src/lib.rs - (line 119) ... ok
[INFO] [stdout] test src/interval.rs - interval::PerfwarnInterval (line 34) ... ok
[INFO] [stdout] test src/interval.rs - interval::ProfileInterval (line 318) ... ok
[INFO] [stdout] test src/level.rs - level::Level::PerfWarn (line 100) ... ok
[INFO] [stdout] test src/lib.rs - (line 152) ... ok
[INFO] [stdout] test src/lib.rs - (line 186) ... ok
[INFO] [stdout] test src/lib.rs - (line 234) ... ok
[INFO] [stdout] test src/interval.rs - interval::PerfwarnIntervalIf (line 171) ... ok
[INFO] [stdout] test src/level.rs - level::Level::Info (line 78) ... ok
[INFO] [stdout] test src/lib.rs - (line 167) ... ok
[INFO] [stdout] test src/lib.rs - (line 318) ... ok
[INFO] [stdout] test src/lib.rs - (line 247) ... ok
[INFO] [stdout] test src/log_record.rs - log_record::LogRecord::level (line 154) ... ok
[INFO] [stdout] test src/lib.rs - (line 279) ... ok
[INFO] [stdout] test src/lib.rs - (line 222) ... ok
[INFO] [stdout] test src/lib.rs - (line 85) ... ok
[INFO] [stdout] test src/log_record.rs - log_record (line 27) ... ok
[INFO] [stdout] test src/log_record.rs - log_record::LogRecord::log_time_since (line 137) ... ok
[INFO] [stdout] test src/lib.rs - (line 204) ... ok
[INFO] [stdout] test src/lib.rs - (line 54) ... ok
[INFO] [stdout] test src/logger.rs - logger::Logger::finish_log_record_async (line 253) ... ok
[INFO] [stdout] test src/logger.rs - logger::Logger::finish_log_record (line 213) ... ok
[INFO] [stdout] test src/lib.rs - (line 68) ... ok
[INFO] [stdout] test src/logger.rs - logger (line 36) ... ok
[INFO] [stdout] test src/log_record.rs - log_record::LogRecord::new (line 103) ... ok
[INFO] [stdout] test src/logger.rs - logger::Logger::finish_log_record_async (line 272) ... ok
[INFO] [stdout] test src/logger.rs - logger (line 87) ... ok
[INFO] [stdout] test src/macros.rs - macros::LoggingDomain::from (line 137) ... ok
[INFO] [stdout] test src/macros.rs - macros::LoggingDomain::is_internal (line 89) ... ok
[INFO] [stdout] test src/macros.rs - macros::LoggingDomain::new (line 71) ... ok
[INFO] [stdout] test src/macros.rs - macros::LoggingDomain (line 48) ... ok
[INFO] [stdout] test src/logger.rs - logger::Logger (line 145) ... ok
[INFO] [stdout] test src/macros.rs - macros::declare_logging_domain (line 183) ... ok
[INFO] [stdout] test src/macros.rs - macros::declare_logging_domain (line 206) ... ok
[INFO] [stdout] test src/macros.rs - macros (line 26) ... ok
[INFO] [stdout] test src/logger.rs - logger::Logger::prepare_to_die (line 324) ... ok
[INFO] [stdout] test src/privacy.rs - privacy (line 32) ... ok
[INFO] [stdout] test src/macros.rs - macros::PrivateFormatter (line 360) ... ok
[INFO] [stdout] test src/macros.rs - macros::declare_logging_domain (line 214) ... ok
[INFO] [stdout] test src/privacy.rs - privacy::&'_str (line 398) ... ok
[INFO] [stdout] test src/macros.rs - macros::declare_logging_domain (line 259) ... ok
[INFO] [stdout] test src/macros.rs - macros::declare_logging_domain (line 272) ... ok
[INFO] [stdout] test src/privacy.rs - privacy (line 60) ... ok
[INFO] [stdout] test src/privacy.rs - privacy (line 49) ... ok
[INFO] [stdout] test src/macros.rs - macros::declare_logging_domain (line 246) ... ok
[INFO] [stdout] test src/privacy.rs - privacy::String (line 371) ... ok
[INFO] [stdout] test src/privacy.rs - privacy::IPromiseItsNotPrivate (line 586) ... ok
[INFO] [stdout] test src/privacy.rs - privacy::Option<T> (line 462) ... ok
[INFO] [stdout] test src/privacy.rs - privacy::&'_[T] (line 424) ... ok
[INFO] [stdout] test src/privacy.rs - privacy::Loggable (line 93) ... ok
[INFO] [stdout] test src/privacy.rs - privacy::LogIt (line 513) ... ok
[INFO] [stdout] test src/privacy.rs - privacy::IPromiseItsNotPrivate (line 604) ... ok
[INFO] [stdout] test src/privacy.rs - privacy::u16 (line 170) ... ok
[INFO] [stdout] test src/privacy.rs - privacy::IPromiseItsNotPrivate (line 620) ... ok
[INFO] [stdout] test src/privacy.rs - privacy::LogIt (line 537) ... ok
[INFO] [stdout] test src/privacy.rs - privacy::u8 (line 143) ... ok
[INFO] [stdout] 
[INFO] [stdout] test result: ok. 124 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 5.34s
[INFO] [stdout] 
[INFO] [stdout] all doctests ran in 6.06s; merged doctests compilation took 0.70s
[INFO] running `Command { std: "docker" "inspect" "992d54765088353ed8f8ea7c4e8d3d85b3ec0d23769702b3d4369946c18c1d66", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "rm" "-f" "992d54765088353ed8f8ea7c4e8d3d85b3ec0d23769702b3d4369946c18c1d66", kill_on_drop: false }`
[INFO] [stdout] 992d54765088353ed8f8ea7c4e8d3d85b3ec0d23769702b3d4369946c18c1d66
